Dec 03 12:07:07.501 INFO testing ffizer-0.3.0 against master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61 for beta-1.31-5
Dec 03 12:07:07.501 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-2/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-2/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 12:07:07.711 INFO [stdout] 6e7c27840f7da58c8508c73157ef79361e6d2dc17189694b79fcfc59ec2d6191
Dec 03 12:07:07.713 INFO running `"docker" "start" "-a" "6e7c27840f7da58c8508c73157ef79361e6d2dc17189694b79fcfc59ec2d6191"`
Dec 03 12:07:08.934 INFO [stderr] usermod: no changes
Dec 03 12:07:09.231 INFO [stderr]    Compiling slog v2.4.1
Dec 03 12:07:09.235 INFO [stderr]    Compiling handlebars v1.1.0
Dec 03 12:07:09.235 INFO [stderr]    Compiling dialoguer v0.1.0
Dec 03 12:07:14.888 INFO [stderr]    Compiling slog-async v2.3.0
Dec 03 12:07:14.890 INFO [stderr]    Compiling slog-term v2.4.0
Dec 03 12:07:24.870 INFO [stderr]    Compiling ffizer v0.3.0 (/source)
Dec 03 12:07:43.723 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 34.77s
Dec 03 12:07:43.742 INFO [stderr] su: No module specific data is present
Dec 03 12:07:44.295 INFO running `"docker" "inspect" "6e7c27840f7da58c8508c73157ef79361e6d2dc17189694b79fcfc59ec2d6191"`
Dec 03 12:07:44.484 INFO running `"docker" "rm" "-f" "6e7c27840f7da58c8508c73157ef79361e6d2dc17189694b79fcfc59ec2d6191"`
Dec 03 12:07:44.734 INFO [stdout] 6e7c27840f7da58c8508c73157ef79361e6d2dc17189694b79fcfc59ec2d6191
Dec 03 12:07:44.736 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-2/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-2/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 12:07:45.079 INFO [stdout] d3b695040225f6be2ddcf0df16f745a7cf956923949ecd4ef2ff81a030d38657
Dec 03 12:07:45.087 INFO running `"docker" "start" "-a" "d3b695040225f6be2ddcf0df16f745a7cf956923949ecd4ef2ff81a030d38657"`
Dec 03 12:07:46.302 INFO [stderr] usermod: no changes
Dec 03 12:07:46.627 INFO [stderr]    Compiling ffizer v0.3.0 (/source)
Dec 03 12:08:07.027 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 20.68s
Dec 03 12:08:07.059 INFO [stderr] su: No module specific data is present
Dec 03 12:08:07.729 INFO running `"docker" "inspect" "d3b695040225f6be2ddcf0df16f745a7cf956923949ecd4ef2ff81a030d38657"`
Dec 03 12:08:07.852 INFO running `"docker" "rm" "-f" "d3b695040225f6be2ddcf0df16f745a7cf956923949ecd4ef2ff81a030d38657"`
Dec 03 12:08:08.015 INFO [stdout] d3b695040225f6be2ddcf0df16f745a7cf956923949ecd4ef2ff81a030d38657
Dec 03 12:08:08.025 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-2/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-2/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 12:08:08.459 INFO [stdout] ab402ea19cf907e3c629fb26cfafb6a3a1e980e66507b38dd06b79ad60359e48
Dec 03 12:08:08.463 INFO running `"docker" "start" "-a" "ab402ea19cf907e3c629fb26cfafb6a3a1e980e66507b38dd06b79ad60359e48"`
Dec 03 12:08:09.245 INFO [stderr] usermod: no changes
Dec 03 12:08:09.464 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.19s
Dec 03 12:08:09.518 INFO [stderr]      Running /target/debug/deps/ffizer-f3ccba8a316174e5
Dec 03 12:08:09.518 INFO [stdout] 
Dec 03 12:08:09.518 INFO [stdout] running 7 tests
Dec 03 12:08:09.518 INFO [stdout] test tests::test_compute_dst_path_asis ... ok
Dec 03 12:08:09.518 INFO [stdout] test template_cfg::tests::test_deserialize_cfg_yaml ... ok
Dec 03 12:08:09.518 INFO [stdout] test tests::test_compute_dst_path_ffizer_handlebars ... ok
Dec 03 12:08:09.525 INFO [stdout] test tests::test_compute_dst_path_rendered_folder ... ok
Dec 03 12:08:09.527 INFO [stdout] test tests::test_path_extension_extraction ... ok
Dec 03 12:08:09.527 INFO [stderr]      Running /target/debug/deps/ffizer-f631a54e15cb6ab8
Dec 03 12:08:09.527 INFO [stdout] test tests::test_compute_dst_path_rendered_filename ... ok
Dec 03 12:08:09.527 INFO [stdout] test tests::test_is_ffizer_handlebars ... ok
Dec 03 12:08:09.527 INFO [stdout] 
Dec 03 12:08:09.527 INFO [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:09.527 INFO [stdout] 
Dec 03 12:08:09.543 INFO [stdout] 
Dec 03 12:08:09.543 INFO [stderr]      Running /target/debug/deps/dir_diff-40d78073cd1e2a7e
Dec 03 12:08:09.543 INFO [stdout] running 0 tests
Dec 03 12:08:09.543 INFO [stdout] 
Dec 03 12:08:09.543 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:09.543 INFO [stdout] 
Dec 03 12:08:09.547 INFO [stdout] 
Dec 03 12:08:09.547 INFO [stderr]      Running /target/debug/deps/e2e-66468a80872b2e30
Dec 03 12:08:09.547 INFO [stdout] running 0 tests
Dec 03 12:08:09.547 INFO [stdout] 
Dec 03 12:08:09.547 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:09.547 INFO [stdout] 
Dec 03 12:08:09.563 INFO [stdout] 
Dec 03 12:08:09.563 INFO [stdout] running 2 tests
Dec 03 12:08:09.575 INFO [stdout] test empty_template ... ok
Dec 03 12:08:09.669 INFO [stderr] error: test failed, to rerun pass '--test e2e'
Dec 03 12:08:09.670 INFO [stdout] test test_1 ... FAILED
Dec 03 12:08:09.670 INFO [stderr] su: No module specific data is present
Dec 03 12:08:09.670 INFO [stdout] 
Dec 03 12:08:09.670 INFO [stdout] failures:
Dec 03 12:08:09.670 INFO [stdout] 
Dec 03 12:08:09.670 INFO [stdout] ---- test_1 stdout ----
Dec 03 12:08:09.670 INFO [stdout] Plan
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: Keep }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "dir_1", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_1", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: MkDir }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "dir_1/file_1_1.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_1/file_1_1.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "dir_2_{{ project_name }}", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_2_", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: MkDir }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "dir_2_{{ project_name }}/file_1_2.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "dir_2_/file_1_2.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_1.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_1.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_2.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_2.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_2.txt.ffizer.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_2.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: Keep }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_3.txt.ffizer.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_3.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRender }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_4_{{ project_name }}.txt", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_4_.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_5_{{ project_name }}.txt.ffizer.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_5_.txt", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRender }
Dec 03 12:08:09.670 INFO [stdout] Action { src_path: ChildPath { relative: "file_6.hbs", base: "./tests/test_1/template", is_symlink: false }, dst_path: ChildPath { relative: "file_6.hbs", base: "/tmp/.tmpCuv6KJ", is_symlink: false }, operation: CopyRaw }
Dec 03 12:08:09.670 INFO [stdout] thread 'test_1' panicked at 'TODO: RenderError(RenderError { desc: "Variable \"project_name\" not found in strict mode.", template_name: None, line_no: Some(1), column_no: Some(12), cause: None })', libcore/result.rs:1009:5
Dec 03 12:08:09.670 INFO [stdout] stack backtrace:
Dec 03 12:08:09.670 INFO [stdout]    0:     0x5563b6c1317f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h3a8b83e1922cbdde
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 03 12:08:09.670 INFO [stdout]    1:     0x5563b6c1c3a7 - std::sys_common::backtrace::print::h00d3155a29b4020f
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 03 12:08:09.670 INFO [stdout]    2:     0x5563b6c16fbf - std::panicking::default_hook::{{closure}}::hd7465c742e79e1bb
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/panicking.rs:211
Dec 03 12:08:09.670 INFO [stdout]    3:     0x5563b6c16cbe - std::panicking::default_hook::h9e3966f2aa2a6e12
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/panicking.rs:221
Dec 03 12:08:09.670 INFO [stdout]    4:     0x5563b6c1769e - std::panicking::rust_panic_with_hook::h587f091ae747d080
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/panicking.rs:476
Dec 03 12:08:09.670 INFO [stdout]    5:     0x5563b6c17241 - std::panicking::continue_panic_fmt::hb3a4fdede87f43a8
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/panicking.rs:390
Dec 03 12:08:09.670 INFO [stdout]    6:     0x5563b6c17125 - rust_begin_unwind
Dec 03 12:08:09.670 INFO [stdout]                                at libstd/panicking.rs:325
Dec 03 12:08:09.670 INFO [stdout]    7:     0x5563b6c5da8c - core::panicking::panic_fmt::h6f9cebf5e7474a0b
Dec 03 12:08:09.670 INFO [stdout]                                at libcore/panicking.rs:77
Dec 03 12:08:09.670 INFO [stdout]    8:     0x5563b65ca980 - core::result::unwrap_failed::h848f1e41880db83e
Dec 03 12:08:09.670 INFO [stdout]                                at libcore/macros.rs:26
Dec 03 12:08:09.670 INFO [stdout]    9:     0x5563b65c7ea0 - <core::result::Result<T, E>>::expect::hcde571234769ef7b
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/result.rs:835
Dec 03 12:08:09.671 INFO [stdout]   10:     0x5563b65ad856 - ffizer::execute::{{closure}}::hee54e25ca6bcfcbb
Dec 03 12:08:09.671 INFO [stdout]                                at src/lib.rs:186
Dec 03 12:08:09.671 INFO [stdout]   11:     0x5563b65a31e6 - core::iter::iterator::Iterator::for_each::{{closure}}::he8bc7ef586c92cab
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/iter/iterator.rs:614
Dec 03 12:08:09.671 INFO [stdout]   12:     0x5563b65a2f25 - core::iter::iterator::Iterator::fold::{{closure}}::h517ad375d1fcc7b9
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/iter/iterator.rs:1695
Dec 03 12:08:09.671 INFO [stdout]   13:     0x5563b659f8c2 - core::iter::iterator::Iterator::try_fold::h5c866db3e796e36c
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/iter/iterator.rs:1583
Dec 03 12:08:09.671 INFO [stdout]   14:     0x5563b659f784 - core::iter::iterator::Iterator::fold::hf78286ee8c318f26
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/iter/iterator.rs:1695
Dec 03 12:08:09.671 INFO [stdout]   15:     0x5563b659f810 - core::iter::iterator::Iterator::for_each::h7e6ebf9598ca05af
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/iter/iterator.rs:614
Dec 03 12:08:09.671 INFO [stdout]   16:     0x5563b65ad497 - ffizer::execute::hd51b41b76990d0d1
Dec 03 12:08:09.671 INFO [stdout]                                at src/lib.rs:176
Dec 03 12:08:09.671 INFO [stdout]   17:     0x5563b65ac423 - ffizer::process::h89086417d8598258
Dec 03 12:08:09.671 INFO [stdout]                                at src/lib.rs:101
Dec 03 12:08:09.671 INFO [stdout]   18:     0x5563b65514bc - e2e::test_1::hda5687f9e70a360f
Dec 03 12:08:09.671 INFO [stdout]                                at tests/e2e.rs:59
Dec 03 12:08:09.671 INFO [stdout]   19:     0x5563b6550d5d - e2e::test_1::{{closure}}::ha1296bda49207748
Dec 03 12:08:09.671 INFO [stdout]                                at tests/e2e.rs:40
Dec 03 12:08:09.671 INFO [stdout]   20:     0x5563b6552afd - core::ops::function::FnOnce::call_once::h7276ddcd702acc5e
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 03 12:08:09.671 INFO [stdout]   21:     0x5563b65560de - <F as alloc::boxed::FnBox<A>>::call_box::hac903f91577a156c
Dec 03 12:08:09.671 INFO [stdout]                                at libtest/lib.rs:1468
Dec 03 12:08:09.671 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 03 12:08:09.671 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 03 12:08:09.671 INFO [stdout]   22:     0x5563b6c27359 - __rust_maybe_catch_panic
Dec 03 12:08:09.671 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 03 12:08:09.671 INFO [stdout]   23:     0x5563b6577d32 - std::sys_common::backtrace::__rust_begin_short_backtrace::hb8f0d0309526c184
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/panicking.rs:289
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/panic.rs:392
Dec 03 12:08:09.671 INFO [stdout]                                at libtest/lib.rs:1423
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 03 12:08:09.671 INFO [stdout]   24:     0x5563b65787e4 - std::panicking::try::do_call::hc2f7c8b9a348d8db
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/panic.rs:313
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/panicking.rs:310
Dec 03 12:08:09.671 INFO [stdout]   25:     0x5563b6c27359 - __rust_maybe_catch_panic
Dec 03 12:08:09.671 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 03 12:08:09.671 INFO [stdout]   26:     0x5563b6565a1c - <F as alloc::boxed::FnBox<A>>::call_box::h6bfded618e480b32
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/panicking.rs:289
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/panic.rs:392
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 03 12:08:09.671 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 03 12:08:09.671 INFO [stdout]   27:     0x5563b6c14e5d - std::sys_common::thread::start_thread::h4c28257d67cdf9cb
Dec 03 12:08:09.671 INFO [stdout]                                at liballoc/boxed.rs:682
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 03 12:08:09.671 INFO [stdout]   28:     0x5563b6c07ac5 - std::sys::unix::thread::Thread::new::thread_start::hfecb2e7eff8fd34f
Dec 03 12:08:09.671 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 03 12:08:09.671 INFO [stdout]   29:     0x7f6592a8d6b9 - start_thread
Dec 03 12:08:09.671 INFO [stdout]   30:     0x7f6592fae41c - clone
Dec 03 12:08:09.671 INFO [stdout]   31:                0x0 - <unknown>
Dec 03 12:08:09.671 INFO [stdout] 
Dec 03 12:08:09.671 INFO [stdout] 
Dec 03 12:08:09.671 INFO [stdout] failures:
Dec 03 12:08:09.671 INFO [stdout]     test_1
Dec 03 12:08:09.671 INFO [stdout] 
Dec 03 12:08:09.671 INFO [stdout] test result: FAILED. 1 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 12:08:09.671 INFO [stdout] 
Dec 03 12:08:10.248 INFO running `"docker" "inspect" "ab402ea19cf907e3c629fb26cfafb6a3a1e980e66507b38dd06b79ad60359e48"`
Dec 03 12:08:10.357 INFO running `"docker" "rm" "-f" "ab402ea19cf907e3c629fb26cfafb6a3a1e980e66507b38dd06b79ad60359e48"`
Dec 03 12:08:10.483 INFO [stdout] ab402ea19cf907e3c629fb26cfafb6a3a1e980e66507b38dd06b79ad60359e48
